Skip to content

test(stress): gate large-catchup on a throughput floor and emit host contention counters - #617

Merged
kriszyp merged 3 commits into
mainfrom
test/large-catchup-throughput-floor
Jul 30, 2026
Merged

test(stress): gate large-catchup on a throughput floor and emit host contention counters#617
kriszyp merged 3 commits into
mainfrom
test/large-catchup-throughput-floor

Conversation

@kriszyp

@kriszyp kriszyp commented Jul 26, 2026

Copy link
Copy Markdown
Member

What

Replaces the fixed wall-clock catch-up budget in integrationTests/stress/largeCatchup.test.mjs with a throughput floor, and adds host-pressure counters to the run log, the job summary, and the uploaded log artifact.

Why — verdict on host contention: refuted, with runner-side evidence

The nightly Large-Data Stress Tests / large-catchup job failed on 2026-07-25 and 2026-07-26 at the identical harper-pro head SHA (86f2955e) and identical pinned core pointer (cda8d63f) that passed on 2026-07-24. Both failures were a wall-clock miss of the 1800s budget at ~87–90% converged, not a wedge.

The working hypothesis going in was host-level I/O and CPU contention on the shared harper-bench box. The runner-side evidence does not support it. sar history on that host (/var/log/sysstat/sa24, sa25, sa26), aligned to each job's startedAt/completedAt:

window (local MDT) 07-24 pass 07-25 fail 07-26 fail
ldavg-1 (20 CPU) 1.48 / 1.95 1.20 / 1.01 / 1.60 1.67 / 0.71 / 0.80
runq-sz 0–3 1–2 0–1
%iowait 4.37 / 0.55 / 1.71 2.52 / 0.74 / 0.79 1.46 / 0.39 / 0.35
%steal 0 0 0
nvme0n1 %util (peak) 24.4% 24.7% 13.1%
nvme0n1 await 6.8 / 5.4 / 2.1 ms 8.4 / 2.5 / 2.6 ms 9.9 / 3.7 / 1.4 ms
plist-sz ~2200 ~2250 ~1550
kbcommit 34–38 GB 36–38 GB 17–19 GB

Every contention indicator is at or below the passing night's on both failing nights. 07-26 in particular: the box had been rebooted the previous evening, was running ~700 fewer processes with half the committed memory, and the disk was at half the passing night's utilisation — and the run still failed.

Two further discriminators point the same way:

  1. A's write phase held up. 07-24 pass 269.3 MB/s, 07-25 fail 251.5 MB/s, 07-26 fail 194.4 MB/s. A host-wide slowdown would hit the write path too; 07-25 was 7% off the passing night on writes while catch-up was 2.3× slower.
  2. The fleet was active on all three nights. The dispatch worker ran codex advise/review jobs during the passing window as well as both failing windows, so its presence does not separate pass from fail.

What is actually happening

Catch-up throughput is bimodal on identical code. Reconstructing the per-poll progress from the job logs:

  • 07-24 (pass): plods at ~1440 records per 10–20s for the first 648s (100 → 40 200), then accelerates sharply — 40 200 → 102 620 in 223s, ~4.5× the earlier rate. Total 900.3s, 11.4 MB/s.
  • 07-25 / 07-26 (fail): never enter the fast mode. Steady ~1440-record bursts for the whole 1800s, ending at 91 280 and 94 180 records — 4.9 and 5.1 MB/s. Extrapolating their own observed rate, both would have converged around 2000–2100s.

Measured 10 GB distribution: 13.5, 11.4, 10.0 MB/s (converged) and ~5.1, ~5.2 MB/s (slow mode). The old 1800s budget sits at 5.7 MB/s equivalent — right in the middle of that distribution, which is why the job coin-flips.

I have not root-caused the fast/slow mode split; that is filed as a follow-up (see Findings in the dispatch). This PR makes the signal trustworthy, it does not fix the throughput variance.

The new criterion

-	// Budget: longer offline = larger backlog = more catch-up time needed.
+	const CATCHUP_FLOOR_MBPS = Number(process.env.HARPER_STRESS_LARGE_CATCHUP_FLOOR_MBPS ?? 2.5);
+	const CATCHUP_BASELINE_MBPS = Number(process.env.HARPER_STRESS_LARGE_CATCHUP_BASELINE_MBPS ?? 10);
+	const CATCHUP_GRACE_SECS = Number(process.env.HARPER_STRESS_LARGE_CATCHUP_GRACE_SECS ?? 120);
 	const CATCHUP_BUDGET_SECS = Number(
-		process.env.HARPER_STRESS_LARGE_CATCHUP_BUDGET_SECS ?? Math.max(600, TARGET_GB * 180)
+		process.env.HARPER_STRESS_LARGE_CATCHUP_BUDGET_SECS ??
+			Math.max(600, Math.ceil((TARGET_GB * 1024) / CATCHUP_FLOOR_MBPS) + CATCHUP_GRACE_SECS)
 	);

The deadline is no longer a chosen constant — it is the time the floor rate needs for this dataset, plus a grace for B's restart/reconnect. Missing it therefore means, and now reads as, "average catch-up throughput was below the floor". At 10 GB that is 4216s (~70 min), inside the job's existing timeout-minutes: 180; a healthy run still exits as soon as it converges (900–2100s observed), so typical nightly wall-clock is unchanged.

Floor = 2.5 MB/s, chosen as half the slowest healthy run measured (5.1 MB/s), not a round number.

What would still catch a genuine 2× replication regression: a 2× slowdown from the slow mode (5.1 → 2.55 MB/s) trips the floor and hard-fails. A 2× slowdown from the fast mode (11.4 → 5.7 MB/s) does not — and honestly cannot, because that is indistinguishable from the slow mode this codebase already produces. That case is covered by the tracked metric instead: any run under CATCHUP_BASELINE_MBPS (10 MB/s) emits a ::warning annotation on the run page and records the number in the metrics artifact, so a sustained downward trend is visible before it ever reaches the floor. Closing that gap properly requires eliminating the bimodality, not a tighter threshold.

Unchanged hard failures: the STALL_SECS (300s) wedge / no-progress guard and its wording from 806a829, over-replication (lastCount > targetCount), OOM and uncaughtException log scans, the RSS_CAP_MB and ANON_CAP_MB memory ceilings, and the A-process-exit watcher during the write phase.

Host-side observability

stressShared.mjs gains readHostCounters() / hostCounterDelta() / sampleHostCounters() / summariseHostSamples() / formatHostCounters(). /proc/stat, /proc/diskstats, /proc/loadavg, /proc/pressure/* and /proc/meminfo are not namespaced by Docker, so the job container reads the whole box through them — exactly the signal the existing in-cgroup stats cannot see (they were identical on pass and fail nights, which is why attribution was impossible from the artifacts).

Emitted as: a suffix on every catch-up poll line; a write host: line and a host (catch-up): + host peaks: pair; inside the assertion failure message itself; and as large-catchup-metrics.json in HARPER_INTEGRATION_TEST_LOG_DIR (i.e. the large-stress-logs-large-catchup-node-24 artifact) plus a GITHUB_STEP_SUMMARY table.

[large-catchup] host (catch-up): load=2.63 iowait=2% steal=0% psi(cpu/io/mem)=0%/2%/0% hostIO=0r/516w MB/s memAvail=24446 MB
[large-catchup] host peaks: load1=2.63 iowait=2% psiIo=2% psiCpu=1% minMemAvail=24435 MB

Test notes

Verified locally at reduced scale per the test's docstring (HARPER_RUN_STRESS_TESTS=1 HARPER_STRESS_LARGE_DATA_GB=1), on the harper-bench host itself:

  • Pass path — converges in 6.0s at 171.7 MB/s, host counters emitted at every stage, large-catchup-metrics.json and the job-summary table written. pass 1 / fail 0.
  • Floor-breach path — forced with HARPER_STRESS_LARGE_CATCHUP_BUDGET_SECS=2; fails with B averaged 0.0 MB/s, under the 1024.0 MB/s catch-up floor (0/10486 records in 2s) — slow replay, not a wedge; a wedge would have tripped the 300s no-progress guard. Host during catch-up: load=1.07 iowait=2% ….
  • Below-baseline warning path — forced with HARPER_STRESS_LARGE_CATCHUP_BASELINE_MBPS=1000; emits the ::warning annotation and still passes.

The floor quoted in messages is ENFORCED_FLOOR_MBPS, derived back out of the actual budget, so it stays truthful when the 600s minimum or an explicit budget override dominates (hence 1024.0 MB/s in the forced case above — that is the arithmetic consequence of a 2s budget, not a config value).

A full 10 GB run was not attempted locally; the wedge guard, over-replication guard and memory caps are untouched code paths.

Not touched

Per the brief: the core submodule pointer is unchanged, Sync Core PR #610 was neither merged nor approved, and largeClone plus the other stress matrix entries are untouched. stressShared.mjs changes are additive — existing exports are unmodified, so the other stress tests are unaffected.

Related context (not addressed here — Kris's merge call)

harper-pro main's core pointer (cda8d63f, 2026-07-22) is 23 commits behind harper main and is missing both replication resume-cursor fixes — 9aca3264c "fix(replication): stop the resume-cursor write freezing the apply worker" and e47f9ca68 "fix(replication): abort the cursor transaction when its commit fails" — which closed #603, whose signature was the apply worker freezing up to 101s under RocksDB write stall. That is the same family as the 72–90s inter-batch stalls still visible in these runs, so the nightly is currently exercising a more fragile Harper than post-fix Harper actually is. Sync Core #610 would land it. It cannot explain the 07-24 → 07-25 change (07-24 passed on the same fix-less core), so it is context, not cause.


Generated by Claude Opus 5.

🤖 Generated with Claude Code

…counters

The nightly Large-Data Stress Tests job failed on 2026-07-25 and 2026-07-26 at
the identical harper-pro head SHA and core pointer that passed on 2026-07-24,
both times as a wall-clock miss of the 1800s catch-up budget at ~90% converged.
Runner-side evidence (sar history on the harper-bench host) shows the box was
not contended on either failing night — loadavg, %iowait, %steal, PSI and nvme
%util were all at or below the passing night's, and the box had ~700 fewer
processes on 7/26 after a reboot. A's write phase also held 251/194 MB/s on the
failing nights against 269 MB/s on the passing one, so the slowdown was
specific to catch-up, not host-wide.

What is actually happening is that catch-up throughput is bimodal on identical
code: 13.5 / 11.4 / 10.0 MB/s when the replay accelerates partway through, and
~5.1 MB/s when it plods for the whole run. A fixed wall-clock budget cannot
separate "slow but healthy" from "regressed" against that spread; it just fails
whichever mode lands past the line.

So the hard gate becomes a throughput floor rather than a clock. The deadline is
derived as the time CATCHUP_FLOOR_MBPS (2.5 MB/s, half the slowest healthy run
measured) needs for the dataset, plus a restart grace, so missing it means and
reads as a throughput regression. CATCHUP_BASELINE_MBPS (10 MB/s) is the tracked
number: falling under it emits an Actions warning annotation and is recorded,
but does not fail the job. Every other hard failure is unchanged — the wedge
no-progress guard, over-replication, OOM, uncaughtException, RSS and cgroup-anon
caps, and A exiting mid-write.

Host pressure is now sampled from /proc (not namespaced by Docker, so it reads
the whole box from inside the job container): loadavg, CPU iowait/steal, PSI
cpu/io/memory stall shares, whole-disk read/write MB/s and MemAvailable. It is
printed on every catch-up poll line, summarised for the write phase and the
catch-up phase separately, included in the failure message, and written to
large-catchup-metrics.json in the uploaded log artifact plus the job summary —
so a future slow run is attributable from the artifact alone.

Co-Authored-By: Claude Opus <noreply@anthropic.com>

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request introduces host-level pressure monitoring (CPU, disk I/O, and PSI metrics from /proc) to the large catch-up stress test, transitioning the test budget from a fixed wall-clock limit to an enforced throughput floor. It also adds functionality to persist run metrics as JSON and write markdown summaries to GitHub Actions. The review feedback highlights a potential TypeError due to missing optional chaining on a regex match, a sample pollution issue in window() that could skew peak rate calculations, and a recommendation to ignore intervals shorter than one second to prevent rate calculation spikes.

Comment thread integrationTests/stress/stressShared.mjs
Comment thread integrationTests/stress/stressShared.mjs
Comment thread integrationTests/stress/stressShared.mjs
Comment thread integrationTests/stress/stressShared.mjs Outdated
Comment thread integrationTests/stress/stressShared.mjs Outdated
@claude

claude Bot commented Jul 26, 2026

Copy link
Copy Markdown
Contributor

Reviewed; no blockers found.

… harden metrics

Applies review findings from PR #617:
- largeCatchup: the grace-adjusted deadline let a converged run post a
  measured rate below ENFORCED_FLOOR_MBPS and still pass, since the gate
  checked convergedAt !== null rather than the achieved rate itself. Gate on
  catchupMBps >= ENFORCED_FLOOR_MBPS directly, which also covers an outright
  timeout without a separate check.
- largeCatchup: the exact_count convergence poll forces a full value scan of
  B's table every 5s, and that scan grows with B's row count and competes
  with the replication replay it's trying to measure. Widen the poll interval
  (HARPER_STRESS_LARGE_CATCHUP_POLL_SECS, default 15s) to reduce how often the
  benchmark scans itself.
- stressShared: writeStressMetrics's fixed path can be read as fresh data
  after a crash that happens before it's called, on a self-hosted runner that
  reuses its workspace across runs. Add clearStressMetrics(), called at suite
  start, so an early failure uploads nothing rather than a stale prior run.
- stressShared: sampleHostCounters().window() pushed its on-demand reading
  into the same samples array the timer fills on a fixed cadence; two entries
  landing milliseconds apart produce a manufactured peak rate when
  summariseHostSamples() walks them pairwise. Stop pushing from window().

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@kriszyp
kriszyp marked this pull request as ready for review July 30, 2026 13:17
@kriszyp
kriszyp requested a review from a team as a code owner July 30, 2026 13:17
@cb1kenobi

Copy link
Copy Markdown
Member

Reviewed 8740c397 — no issues found. This PR looks good, nice job!


Generated by Barber AI

?.[1] short-circuits to undefined when /proc/stat's cpu line is missing,
but the following .trim() ran unconditionally and threw before the ?? []
fallback could apply — breaking readHostCounters' "return null for any
source the platform lacks" contract and surfacing as an uncaught
exception in the setInterval sampling callback.

Addresses PR #617 review threads from gemini-code-assist and claude.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@cb1kenobi

Copy link
Copy Markdown
Member

Reviewed f8f9e71a — no issues found. This PR looks good, nice job!


Generated by Barber AI

@kriszyp
kriszyp requested review from DavidCockerill, Devin-Holland and Ethan-Arrowood and removed request for a team and Devin-Holland July 30, 2026 17:12
@kriszyp
kriszyp merged commit c8f5beb into main Jul 30, 2026
27 checks passed
kriszyp added a commit that referenced this pull request Jul 30, 2026
… harden metrics

Applies review findings from PR #617:
- largeCatchup: the grace-adjusted deadline let a converged run post a
  measured rate below ENFORCED_FLOOR_MBPS and still pass, since the gate
  checked convergedAt !== null rather than the achieved rate itself. Gate on
  catchupMBps >= ENFORCED_FLOOR_MBPS directly, which also covers an outright
  timeout without a separate check.
- largeCatchup: the exact_count convergence poll forces a full value scan of
  B's table every 5s, and that scan grows with B's row count and competes
  with the replication replay it's trying to measure. Widen the poll interval
  (HARPER_STRESS_LARGE_CATCHUP_POLL_SECS, default 15s) to reduce how often the
  benchmark scans itself.
- stressShared: writeStressMetrics's fixed path can be read as fresh data
  after a crash that happens before it's called, on a self-hosted runner that
  reuses its workspace across runs. Add clearStressMetrics(), called at suite
  start, so an early failure uploads nothing rather than a stale prior run.
- stressShared: sampleHostCounters().window() pushed its on-demand reading
  into the same samples array the timer fills on a fixed cadence; two entries
  landing milliseconds apart produce a manufactured peak rate when
  summariseHostSamples() walks them pairwise. Stop pushing from window().

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@kriszyp
kriszyp deleted the test/large-catchup-throughput-floor branch July 30, 2026 17:13
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Replication catch-up: synchronous resume-cursor write freezes the worker event loop for up to 101s under RocksDB write stall

2 participants